

# FORMAT
#   01       02   03  04     05
#   THREADID HOUR MIN SECOND MILLISEC

ls -1art | \
grep 'test_filename[0123456789].log_20120301' | \
xargs egrep '(function_start|function_end)' | \
cut -f2- -d: | \
grep '^\[' | \
sed -e 's/\[\([0-9]*\):\([0-9]*\):\([0-9]*\)\.\([0-9]*\)-\([0-9]*\)\]/\5 \1 \2 \3 \4/' | \
awk '
BEGIN {
  totalDuration = 0
  totalCount = 0
}

/function_start/ {
   sec = ($2 * 3600) + ($3 * 60) + $4 + ($5 / 1000)
   if (!($1 in threads)) {
      threads[$1] = $1
   }
   start[$1] = sec
}

/function_end/ {
   if (!($1 in start)) {
      print "ERROR: "$1" does not have a corresponding start time"
   } else {
      endts = ($2 * 3600) + ($3 * 60) + $4 + ($5 / 1000)
      startts = start[$1]
      duration = endts - startts
      totalCount++
      totalDuration += duration
      #if (duration > 1.0) {
      #   print $2":"$3":"$4"."$5, startts, endts, duration, totalCount, totalDuration
      #}      
   }
}

END {
   print "Total Duration:", totalDuration
   print "Total function Calls:", totalCount
   print "Average Duration:", (totalDuration/totalCount)
   print "Detected threads:"
   for (threadID in threads) {
      print threadID
   }
}'
